主题
Go 典型故障排查：从八种症状找到下一份证据
CPU 高、内存涨、请求超时，常常会同时出现。它们未必是三个故障：慢查询可以占住连接，连接池排队又会积累 goroutine；请求重试再把 CPU 与内存推高。如果分别看到一个指标就改一个参数，很容易把问题放大。
排查先保留一条共同时间线：哪个版本、哪些实例、什么请求比例，在什么时候开始变坏。再区分执行、等待和资源保留，找能否证伪当前猜测的证据。本文把八类故障逐项展开，并提供可在五秒超时保护下运行的本地实验。环境是 Go 1.27.2、Linux/amd64；没有压测公共服务，没有操作用户生产进程。
第一轮先缩小范围，不同时打开所有诊断开关
| 先看什么 | 帮助做什么判断 | 采集风险 |
|---|---|---|
| 错误率、p95/p99、QPS、发布与配置时间 | 是流量变化、局部实例，还是版本相关？ | 低；先复用已有观测 |
| 进程/容器 CPU、内存、FD、连接池状态 | 哪种资源接近上限？ | 通常低；注意指标口径 |
| 少量 goroutine 栈、短 CPU profile | 大家卡在哪、CPU 花在哪？ | 有开销与敏感路径信息，限定实例和窗口 |
| heap/allocs 差分、block/mutex、短 trace | 进一步区分引用保留、抖动、锁与调度 | 更依赖采样配置；全量采样或强制 GC 可扰动系统 |
| core、调试器暂停、数据库执行计划分析 | 需要更深状态或执行证据时 | 高；可能暂停进程、泄露数据或真正执行查询 |
若错误正在扩大，可以先按预案限流、熔断不重要流量或回退最近变更，同时保留最小现场。缓解之后再补充证据。扩容、重启和调大上限都有代价：它们可以争取时间，也会清空部分现场；别把“暂时不报警”当成根因已经修好。[1]
正在绘制图示…
查看图源代码
flowchart LR
A[下游查询变慢] --> B[连接占用变长]
B --> C[连接池开始排队]
C --> D[请求与 goroutine 积压]
D --> E[内存与超时增加]
E --> F[客户端或内部重试]
F --> B
F --> G[额外 CPU 与分配]
这是一个可能的因果链，不是从指标共振就能直接认定的根因。下面的步骤就是用池等待、驱动调用、服务端查询和重试证据逐段确认它。
1. CPU 飙高：先确定 CPU 是谁用掉的
先确认“100%”的分母：是一核、整个容器配额，还是整个宿主机？同时看吞吐是否也上涨、是否被 cgroup 限额，以及高 CPU 是所有实例还是少数实例。CPU 高但单位请求 CPU 没变，可能只是负载增加；吞吐没变而 CPU 突增，更值得关联发布、异常重试、编码/压缩和 GC。[1]
然后取短 CPU profile，先看 flat 热点，再看 cum 调用路径：
| 热点证据 | 下一份证据 | 修复方向 |
|---|---|---|
| 业务循环、解析或序列化 | 输入规模、循环退出条件、请求来源 | 算法、输入上限、避免重复工作 |
runtime.mallocgc、GC 相关函数 | allocs 增量、分配字节/请求、GC CPU | 减少临时对象，检查新引入的大对象 |
| 错误处理/日志/重试热路径 | 错误率、尝试次数、日志速率 | 退避、重试预算、减少重复日志 |
| profile 很轻但请求慢 | goroutine、block、trace、下游指标 | 转查等待，不因 CPU profile 空而否认故障 |
本地 CPU 反例只运行 200 ms 的有界忙循环，真实采样结果：
text
Duration: 199.97ms, Total samples = 190ms (95.01%)
190ms 100% main.busy这证明本例的热点确实在 busy，而不是仅凭“CPU 高”猜它在忙循环。采样窗口很短，不能当作精确计费。多个核的 CPU 样本会累加，也不能把 CPU 总时间直接当某个请求的墙钟时间。[2]
2. 内存泄漏 / 内存不降：先分清哪一种内存
Go GC 只会回收不可达对象；缓存、全局容器、未结束 goroutine 的栈都可能继续持有对象。即使对象已回收，运行时也可能暂时保留页以备复用，RSS 不必立即下降。因此“流量回落了，容器内存没掉”不足以单独证明泄漏。[3]
| 口径 | 看什么 | 常见误读 |
|---|---|---|
heap inuse_space、HeapAlloc | 活跃堆对象与分配来源 | 不等于所有进程内存；profile 与实时计数的更新时间也不同 |
alloc_space、TotalAlloc 增量 | 一段时间制造了多少分配 | 是累计流量，不是当前保留量 |
HeapInuse、HeapIdle、HeapReleased | 堆页使用、空闲、归还 OS 的情况 | 空闲堆页不自动等于对象泄漏 |
| 栈、运行时元数据、cgo/native 内存 | Go 堆以外的占用 | cgo 分配不能只靠 Go heap 找全 |
Linux RSS / smaps_rollup | 进程驻留映射 | 还含栈、映射文件、共享页等 |
| 容器 memory 指标 | 容器计费的整体内存 | 可能包含页缓存和同容器其他进程，与单进程 RSS 不同 |
先在相近业务阶段比较 GC 后的存活堆，查看哪条分配栈持续增长；再查持有路径：缓存是否无上限、slice 是否保留大底层数组、队列是否只进不出。heap 指向分配处，不直接给出完整引用链。若 Go 存活堆稳定而 RSS 持续增长，继续看 native 分配、映射与页保留，不能反复对 heap 图做同一个解释。[2][3][4]
本地实验保留 4 MiB 对象，清空全局引用再做 GC，断言只采用宽裕的相对阈值：
text
heap: retained_growth_over_3MiB=true released_over_3MiB=true这里只验证 Go 堆对象确实保留并释放，没有测得 RSS 必然下降。debug.FreeOSMemory 会触发 GC 并尝试向 OS 归还内存，不能解除仍然可达的引用，也不应当作周期性掩盖泄漏的“修复”。[3]
3. goroutine 泄漏：查的是生命周期，不只是数量
正常 worker、HTTP keep-alive 和后台维护也会等待。先把 goroutine 数量和并发请求、队列深度对齐；流量回落后再取几次栈，查某一创建路径下相同阻塞栈是否持续累积。文本 goroutine profile 中的 channel send/receive、锁、网络读写是入口，还要问“谁负责让它结束”。[2]
常见断点是调用者超时后不再接结果，生产者却永远卡在无缓冲 channel 发送；或者 worker 等的队列不关闭，也不监听取消。解决方式取决于所有权：把取消传到工作中，对发送和接收提供取消分支，并在关闭组件时等待后台任务真正退出。仅调用 cancel() 不是自动杀 goroutine，工作函数必须观察它。
本文的 3 个 worker 故意先等在取消信号上，采样确认栈里出现 main.stuck，然后取消并 Join：
go
func stuck(ctx context.Context, ready chan<- struct{}, wg *sync.WaitGroup) {
defer wg.Done()
ready <- struct{}{}
<-ctx.Done()
}text
goroutine: stuck_stack_found=true
goroutine: joined=3这是一个“疑似卡住但能正确结束”的对照例，强调一次等待快照不能直接判定泄漏。后续回归测试应启动组件、执行请求、取消/关闭、等待退出，再检测额外 goroutine；不能随便忽略整类业务函数的栈。
4. 死锁：沿“等谁”画环
死锁的关键是等待条件再也不能满足。拿到栈后逐条写：A 持有什么，在等谁；B 持有什么，在等谁；是否存在锁顺序相反、持锁等待 channel、重复锁定非重入 Mutex，或在受限连接池里持有唯一连接又申请第二条连接。[5]
正在绘制图示…
查看图源代码
flowchart LR
A[goroutine A<br/>持有锁 X] -->|等待锁 Y| B[goroutine B<br/>持有锁 Y]
B -->|等待锁 X| A
图中是一种锁顺序环。修复要打断依赖，例如统一获取顺序、把外部等待移出临界区。给等待加 timeout 可以限制影响，但如果没有恢复与资源释放语义，超时只会把死锁换成反复失败。
运行时能发现某些全局无进展状态。本例在独立子进程执行对 nil channel 的接收，五秒超时兜底，实际立即以状态码 2 退出：
text
fatal error: all goroutines are asleep - deadlock!
goroutine 1 [chan receive (nil chan)]:
main.run()完整栈保存在实验输出，正文省略机器路径和行号。现实服务若仍有其他 goroutine 在工作、定时器或外部事件，局部死锁未必触发这条全局错误。没有 fatal 不等于没有死锁；需要请求级无进展和等待环的证据。race detector 查数据竞争，也不是通用死锁检测器。[5][6]
5. GC 压力过大：把分配速率和存活量分开看
小存活堆也可能 GC 很忙：如果每个请求产生很多临时对象，GC 刚清完就又有一批分配。观察一段时间内 /gc/heap/allocs:bytes 增量、GC CPU、周期次数、存活堆，以及每请求分配量；CPU profile 若显示 GC 与分配热点，allocs profile 再把来源定位到代码。[3][7]
本地实验把 GOGC 的运行时等价设置临时调低到 20，分配 256 块 128 KiB 的临时堆切片，再恢复原设置。没有在这一段主动调用 GC，实际观察到：
text
gc: allocated_over_32MiB=true automatic_collections=true它证明可以用低存活、较高分配速率制造自动 GC，并不说明生产应该设 GOGC=20。提高 GOGC 通常以更多内存换更少 GC 工作；降低内存目标也可能让 GC 更忙。GOMEMLIMIT 是 Go 运行时的软内存限制，不是容器总 RSS 的硬上限，还需给 native、映射和其他开销留空间。先减少不必要的分配与扫描对象，再在内存预算内调参数。[3]
GC 周期总时长不等于 STW。怀疑 GC 导致 p99 时，用 trace 对齐目标请求与真正的暂停、assist 和调度等待，不要只把“发生过一次 GC”当作因果。
6. 连接池耗尽：先看连接借走后去了哪里
database/sql.DB 是池，不是一条连接。SetMaxOpenConns 达到上限后，新请求可能等待可用连接；SetMaxIdleConns 控制空闲保留，不是并发总上限。调大池前，先看数据库是否还有容量，多个实例的总连接预算是多少。[8]
第一组证据是 DB.Stats() 的 OpenConnections、InUse、Idle、MaxOpenConnections，以及时间窗里的 WaitCount、WaitDuration 增量。再结合栈判断是在申请连接、执行查询、读 Rows，还是等事务完成。累计值一直大不意味着当前还在排队；跨窗口的进行中等待也会影响简单平均值。
本文使用真正的 database/sql 池加一个本地假驱动，最大连接数为 1。先持有这条连接，再尝试用 20 ms context 获取第二条：
text
pool: deadline=true inuse=1 waitcount=1 waited=true
pool: acquired after close=true关闭专用 Conn 后，下一次获取成功。这些输出直接验证了“等的是池容量”，而不是假驱动里的查询执行。实验没有数据库服务，不能由它推断 MySQL 或 PostgreSQL 的服务端行为。
排查借用生命周期：Rows 是否关闭并检查 Err，事务是否 Commit/Rollback，专用 Conn 是否 Close，慢消费者是否长时间占着流式结果。关闭专用 Conn 通常是归还池，并不意味着立刻关闭 TCP。HTTP 连接复用也有类似生命周期问题：响应 Body 必须正确关闭，是否读完会影响复用；不能为了复用而无限制读取不可信的巨大响应。[8][9]
7. 慢查询：客户端“慢”要拆成几段
一条 SQL 调用的客户端总耗时可能包含等池、建连/TLS、网络、服务端锁等待、执行、结果传输与解码。先分出池等待，才能知道是否真的需要改执行计划。
同一个假驱动的第二组实验让池空闲，但在 ExecContext 内等待 30 ms；调用方 10 ms 超时，结果是：
text
query: deadline=true pool_wait_delta=0与前一组相比，超时相同，证据却指向不同层。这仅是驱动层延迟模拟，不能称为实测慢 SQL。
| 下一份证据 | 可以区分什么 | 采取动作前的约束 |
|---|---|---|
| 查询指纹、参数分布、返回行数 | 某种输入突然放大工作量 | 日志脱敏，避免记录客户秘密 |
| 数据库活动会话与等待事件 | 计算/IO，还是被其他事务锁住 | 和请求时间窗、连接身份对应 |
| 估计执行计划 | 访问路径、连接顺序、基数估计 | 使用目标数据库及目标版本 |
| 受控的实际执行计划与 buffer/IO 统计 | 估计和实际行数、循环次数差异 | EXPLAIN ANALYZE 会真正执行，必须考虑耗时与副作用 |
| 慢查询日志、锁持有者、索引与统计信息 | 计划回退、热点锁、数据分布变化 | 不把“加索引”当作所有慢查询的默认答案 |
以 PostgreSQL 为例，EXPLAIN 与 EXPLAIN ANALYZE 的用途不同，后者执行语句并报告实际统计。生产写语句、锁影响和超长查询需要专门评估，不能把诊断命令无差别运行在现场。本篇依据官方文档说明路径，没有生成或伪造任何数据库执行计划。[10]
8. 文件描述符耗尽：数清文件、socket 和归还路径
Linux 的 FD 包含普通文件、socket、pipe、epoll 等资源。先读目标进程的限制与 /proc/PID/fd 分类，观察增长是否跟请求完成一起回落，再查哪一类对象一直没关闭。EMFILE 指进程达到描述符上限；系统范围的文件表耗尽通常对应 ENFILE，不能当成同一问题。[4][11]
本文只在子进程中把 RLIMIT_NOFILE 软限制降低到 64，最多尝试打开 128 次 /dev/null，每个成功对象都在退出前关闭。它不会提高权限，不会修改父进程或系统的限制。真实输出：
text
fd: emfile=true opened=5959 不是硬编码预期：进程启动时已有标准流和运行时描述符。测试断言的是 errors.Is(err, syscall.EMFILE)，并有五秒超时与最大打开次数双重约束。
典型代码问题是在长期运行循环里 defer f.Close()，关闭要等整个函数返回；该在单次操作完成时关闭的资源一直累积。网络侧要查响应 Body、未结束 Rows、未回收的连接和重连风暴。提高限制可以缓解，但若归还路径仍然缺失，只是延后下一次耗尽；过多 socket 也会增加内存和下游压力。
收束到可以复验的根因
根因记录至少包含：症状时间窗、定位证据、导致现象的机制、修复动作，以及修复后同等条件下哪项证据消失了。例如“把 MaxOpenConns 从 10 改为 100”只是动作；“Rows 在错误路径未关闭，修复后 InUse 与 goroutine 在流量回落后恢复，WaitCount 增速回落”才是可复核的解释。
本次实验中 CPU、保留堆/释放、自动 GC、goroutine 生命周期、池等待、驱动延迟、FD 耗尽和全局死锁均实际运行。假驱动不代表真实数据库；RSS/native 内存、生产锁环、服务端慢计划没有被实测。普通与 race 测试分别运行：pool/memory/goroutine 还在 race 测试进程中直接验证；故意死锁和降低 FD 上限只放在普通子进程，不能说 race 检测过这些子进程内部。
依据
- Go diagnostics：诊断手段、采集成本与相互影响。
- Go 1.27.2 runtime/pprof：CPU、内存、goroutine、阻塞与锁 profile。
- Go GC guide、runtime.MemStats、runtime/debug：堆、GC、软限制与 FreeOSMemory。
- Linux kernel /proc 文档：fd、status、smaps_rollup 等口径；cgroup v2 内存接口。
- Go 1.27.2 runtime/proc.go：
checkdead的检测边界；sync.Mutex。 - Go race detector：检测对象是数据竞争。
- Go 1.27.2 runtime/metrics：分配、GC 与 goroutine 指标。
- Go 管理数据库连接、database/sql：池限制、统计、Conn、Rows 与事务生命周期。
- Go 1.27.2 net/http：响应 Body 关闭与连接复用。
- PostgreSQL 18：Using EXPLAIN：计划与实际执行的区别。
- Linux getrlimit(2)、open(2)：RLIMIT_NOFILE、EMFILE 与 ENFILE。
完整本地实验
以下文件需要 Go 1.27.2、Linux 和 GNU timeout。运行 bash run.sh out；不要把故障模式嵌入真实服务。fd 只降低短命子进程的软限制，deadlock 预期退出码为 2，其余模式预期成功。没有第三方依赖，没有真实数据库连接。
go.mod
go.mod
module example.com/faultlab
go 1.27.2main.go
代码块 · 243 行 · 点击收起 / 展开
go
package main
import (
"context"
"database/sql"
"database/sql/driver"
"errors"
"fmt"
"os"
"reflect"
"runtime"
"runtime/debug"
"runtime/pprof"
"strings"
"sync"
"syscall"
"time"
)
type fakeDriver struct{}
type fakeConn struct{}
func (fakeDriver) Open(string) (driver.Conn, error) { return fakeConn{}, nil }
func (fakeConn) Prepare(string) (driver.Stmt, error) { return nil, errors.New("not supported") }
func (fakeConn) Close() error { return nil }
func (fakeConn) Begin() (driver.Tx, error) { return nil, errors.New("not supported") }
func (fakeConn) ExecContext(ctx context.Context, _ string, _ []driver.NamedValue) (driver.Result, error) {
timer := time.NewTimer(30 * time.Millisecond)
defer timer.Stop()
select {
case <-ctx.Done():
return nil, ctx.Err()
case <-timer.C:
return driver.RowsAffected(1), nil
}
}
var registerDriver sync.Once
func pool() error {
registerDriver.Do(func() { sql.Register("fault-demo", fakeDriver{}) })
db, err := sql.Open("fault-demo", "")
if err != nil {
return err
}
defer db.Close()
db.SetMaxOpenConns(1)
c, err := db.Conn(context.Background())
if err != nil {
return err
}
ctx, cancel := context.WithTimeout(context.Background(), 20*time.Millisecond)
_, waitErr := db.Conn(ctx)
cancel()
s := db.Stats()
fmt.Printf("pool: deadline=%v inuse=%d waitcount=%d waited=%v\n", errors.Is(waitErr, context.DeadlineExceeded), s.InUse, s.WaitCount, s.WaitDuration > 0)
if !errors.Is(waitErr, context.DeadlineExceeded) || s.WaitCount != 1 {
c.Close()
return errors.New("pool assertion")
}
if err := c.Close(); err != nil {
return err
}
c, err = db.Conn(context.Background())
if err != nil {
return err
}
fmt.Println("pool: acquired after close=true")
if err := c.Close(); err != nil {
return err
}
before := db.Stats().WaitCount
ctx, cancel = context.WithTimeout(context.Background(), 10*time.Millisecond)
_, queryErr := db.ExecContext(ctx, "simulated slow operation")
cancel()
fmt.Printf("query: deadline=%v pool_wait_delta=%d\n", errors.Is(queryErr, context.DeadlineExceeded), db.Stats().WaitCount-before)
if !errors.Is(queryErr, context.DeadlineExceeded) || db.Stats().WaitCount != before {
return errors.New("query assertion")
}
return nil
}
var held [][]byte
var trash []byte
func memory() error {
runtime.GC()
var start, live, end runtime.MemStats
runtime.ReadMemStats(&start)
for range 64 {
b := make([]byte, 64<<10)
for i := range b {
b[i] = 1
}
held = append(held, b)
}
runtime.GC()
runtime.ReadMemStats(&live)
held = nil
runtime.GC()
runtime.GC()
runtime.ReadMemStats(&end)
fmt.Printf("heap: retained_growth_over_3MiB=%v released_over_3MiB=%v\n", live.HeapAlloc > start.HeapAlloc+3<<20, live.HeapAlloc > end.HeapAlloc+3<<20)
if live.HeapAlloc <= start.HeapAlloc+3<<20 || live.HeapAlloc <= end.HeapAlloc+3<<20 {
return errors.New("heap assertion")
}
old := debug.SetGCPercent(20)
defer debug.SetGCPercent(old)
runtime.ReadMemStats(&start)
for range 256 {
trash = make([]byte, 128<<10)
}
trash = nil
runtime.ReadMemStats(&end)
fmt.Printf("gc: allocated_over_32MiB=%v automatic_collections=%v\n", end.TotalAlloc-start.TotalAlloc >= 32<<20, end.NumGC > start.NumGC)
if end.TotalAlloc-start.TotalAlloc < 32<<20 || end.NumGC <= start.NumGC {
return errors.New("gc assertion")
}
return nil
}
//go:noinline
func stuck(ctx context.Context, ready chan<- struct{}, wg *sync.WaitGroup) {
defer wg.Done()
ready <- struct{}{}
<-ctx.Done()
}
func goroutines() error {
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
ready := make(chan struct{}, 3)
var wg sync.WaitGroup
for range 3 {
wg.Add(1)
go stuck(ctx, ready, &wg)
}
for range 3 {
<-ready
}
var b strings.Builder
if err := pprof.Lookup("goroutine").WriteTo(&b, 2); err != nil {
return err
}
name := runtime.FuncForPC(reflect.ValueOf(stuck).Pointer()).Name()
found := strings.Contains(b.String(), name+"(")
fmt.Printf("goroutine: stuck_stack_found=%v\n", found)
cancel()
wg.Wait()
fmt.Println("goroutine: joined=3")
if !found {
return errors.New("missing stuck stack")
}
return nil
}
var total uint64
//go:noinline
func busy() {
until := time.Now().Add(200 * time.Millisecond)
x := uint64(1)
for time.Now().Before(until) {
for range 10000 {
x = x*1664525 + 1013904223
}
}
total = x
}
func cpu(path string) error {
f, err := os.Create(path)
if err != nil {
return err
}
if err := pprof.StartCPUProfile(f); err != nil {
f.Close()
return err
}
busy()
pprof.StopCPUProfile()
return f.Close()
}
func fd() error {
var lim syscall.Rlimit
if err := syscall.Getrlimit(syscall.RLIMIT_NOFILE, &lim); err != nil {
return err
}
if lim.Cur > 64 {
lim.Cur = 64
}
if err := syscall.Setrlimit(syscall.RLIMIT_NOFILE, &lim); err != nil {
return err
}
files := []*os.File{}
defer func() {
for _, f := range files {
f.Close()
}
}()
for range 128 {
f, err := os.Open("/dev/null")
if err != nil {
fmt.Printf("fd: emfile=%v opened=%d\n", errors.Is(err, syscall.EMFILE), len(files))
if errors.Is(err, syscall.EMFILE) {
return nil
}
return err
}
files = append(files, f)
}
return errors.New("limit not reached within bound")
}
func run() error {
if len(os.Args) < 2 {
return errors.New("mode required")
}
switch os.Args[1] {
case "pool":
return pool()
case "memory":
return memory()
case "goroutine":
return goroutines()
case "cpu":
if len(os.Args) != 3 {
return errors.New("profile path required")
}
return cpu(os.Args[2])
case "fd":
return fd()
case "deadlock":
var ch chan int
<-ch
default:
return errors.New("unknown mode")
}
return nil
}
func main() {
if err := run(); err != nil {
fmt.Fprintln(os.Stderr, err)
os.Exit(1)
}
}main_test.go
代码块 · 43 行 · 点击收起 / 展开
go
package main
import (
"context"
"os/exec"
"path/filepath"
"strings"
"testing"
"time"
)
func TestChildFailures(t *testing.T) {
path := filepath.Join(t.TempDir(), "lab")
if out, err := exec.Command("go", "build", "-o", path, ".").CombinedOutput(); err != nil {
t.Fatalf("build %v %s", err, out)
}
for _, mode := range []string{"pool", "memory", "goroutine", "fd", "deadlock"} {
t.Run(mode, func(t *testing.T) {
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()
out, err := exec.CommandContext(ctx, path, mode).CombinedOutput()
if ctx.Err() != nil {
t.Fatalf("child exceeded limit: %s", out)
}
if mode == "deadlock" {
if err == nil || !strings.Contains(string(out), "all goroutines are asleep - deadlock!") {
t.Fatalf("unexpected deadlock: %v %s", err, out)
}
} else if err != nil {
t.Fatalf("%v %s", err, out)
}
t.Log(strings.TrimSpace(string(out)))
})
}
}
func TestInProcessSafeCases(t *testing.T) {
for _, f := range []func() error{pool, memory, goroutines} {
if err := f(); err != nil {
t.Fatal(err)
}
}
}run.sh
bash
#!/usr/bin/env bash
set -euo pipefail
export TZ=UTC
out=${1:-out}
mkdir -p "$out"
{ go version; go env GOOS GOARCH; } > "$out/environment.txt"
go test -count=2 -v . > "$out/test.txt"
go test -count=2 -race . > "$out/race.txt"
go vet . > "$out/vet.txt"
go build -o "$out/lab" .
for mode in pool memory goroutine fd; do timeout 5s "$out/lab" "$mode" > "$out/$mode.txt"; done
set +e
timeout 5s "$out/lab" deadlock > "$out/deadlock.txt" 2>&1
status=$?
set -e
[ "$status" -eq 2 ] || { echo "unexpected deadlock status=$status"; exit 1; }
timeout 5s "$out/lab" cpu "$out/cpu.pb.gz"
go tool pprof -top "$out/lab" "$out/cpu.pb.gz" > "$out/cpu-top.txt"